Skip to content

ct: Include actual error reason in CTH failure test log - #11231

Open
u3s wants to merge 1 commit into
erlang:maintfrom
u3s:kuba/common_test/hook_fail_test_log/OTP-20192
Open

u3s wants to merge 1 commit into
erlang:maintfrom
u3s:kuba/common_test/hook_fail_test_log/OTP-20192

Conversation

@u3s

@u3s u3s commented Jun 12, 2026

Copy link
Copy Markdown
Contributor

When a CT hook callback crashes, the test case minor log only shows a generic message like "mod:fun/N CTH call failed" in the "=== Reason:" line. The actual error and stacktrace are logged earlier in the "Suite Hook" section but not propagated to the test summary.

Include the exception class, reason, and top stack frame in the thrown error string so it reaches the "=== Reason:" output that developers and automated tools use to classify failures.

@u3s u3s self-assigned this Jun 12, 2026
@u3s u3s added the team:PS Assigned to OTP team PS label Jun 12, 2026
@github-actions

github-actions Bot commented Jun 12, 2026 •

Copy link
Copy Markdown
Contributor

CT Test Results

  2 files   58 suites   1h 17m 7s ⏱️
469 tests 454 ✅ 15 💤 0 ❌
503 runs  485 ✅ 18 💤 0 ❌

Results for commit 405acc4.

♻️ This comment has been updated with latest results.

To speed up review, make sure that you have read Contributing to Erlang/OTP and that all checks pass.

See the TESTING and DEVELOPMENT HowTo guides for details about how to run test locally.

Artifacts

// Erlang/OTP Github Action Bot

@u3s u3s added the testing currently being tested, tag is used by OTP internal CI label Jun 15, 2026
@u3s
u3s requested a review from Mikaka27 June 15, 2026 12:20
@u3s
u3s force-pushed the kuba/common_test/hook_fail_test_log/OTP-20192 branch 2 times, most recently from 6f2f667 to 8eb2daf Compare June 16, 2026 08:52
@u3s u3s removed the testing currently being tested, tag is used by OTP internal CI label Jul 3, 2026
@Mikaka27 Mikaka27 self-assigned this Aug 5, 2026
@Mikaka27
Mikaka27 force-pushed the kuba/common_test/hook_fail_test_log/OTP-20192 branch 2 times, most recently from 2388277 to 623d115 Compare October 8, 2026 17:56
@Mikaka27 Mikaka27 added the testing currently being tested, tag is used by OTP internal CI label Oct 8, 2026
@u3s u3s assigned u3s and unassigned u3s Oct 12, 2026
@Mikaka27
Mikaka27 force-pushed the kuba/common_test/hook_fail_test_log/OTP-20192 branch 3 times, most recently from b230c5a to 728182e Compare October 19, 2026 18:34
@Mikaka27
Mikaka27 requested a balanced review from Copilot October 20, 2026 08:16

Copilot AI left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🟡 Changes recommended

Non-printable list exceptions become unreadable, and the regression test does not verify the changed minor-log output.

2 open issues
What changed in this PR

Improves Common Test hook failure diagnostics by carrying exception details into testcase logs.

Changes:

  • Propagates exception class, reason, and stacktrace from hook failures.
  • Adjusts minor-log reason formatting and multiline indentation.
  • Updates failure expectations and adds a nested timeout regression case.
File Description
lib/​common_test/​test/​ct_hooks_SUITE.erl Updates expected failures and adds timeout coverage.
lib/​common_test/​test/​ct_hooks_SUITE_data/​cth/​tests/​crash_post_end_tc_cth.erl Adds a hook that produces a nested timeout failure.
lib/​common_test/​src/​test_server_ctrl.erl Adjusts exception rendering and indentation.
lib/​common_test/​src/​ct_hooks.erl Preserves hook exception details.

Review effort: Balanced

Comment thread lib/common_test/src/test_server_ctrl.erl Outdated
Comment thread lib/common_test/test/ct_hooks_SUITE.erl Outdated
@Mikaka27
Mikaka27 force-pushed the kuba/common_test/hook_fail_test_log/OTP-20192 branch from 728182e to 1c86749 Compare October 20, 2026 09:59
Mikaka27
Mikaka27 previously approved these changes Oct 22, 2026
ct_logs:log("Suite Hook","Call to CTH failed: ~w:~tp",
[error,{Reason,Trace}]),
[Class,{Reason,Trace}]),
throw({error_in_cth_call,

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

  • potentially incompatible ?
  • deliver to maint-29 only?

11.4 AP-4: Failure term shape change

  • WHY: the CTH failure reason changes from Str to
    {Str, Stacktrace}. Where it shows up, per the updated
    ct_hooks_SUITE expectations:

    • tc_done: {Suite, TC, {failed, {error, {Str, Trace}}}}
    • tc_auto_skip for later cases:
      {Suite, TC, {failed, {Suite, init_per_suite, {failed, {Str, Trace}}}}}
    • on_tc_fail/4 and on_tc_skip/4 hook callbacks receive the same
      terms.

    Custom event handlers or hooks (CI integrations, rebar3 plugins,
    internal tooling) that match on a string will now see a tuple. In
    OTP itself, only ct_hooks_SUITE matched on "CTH call failed"
    (checked with git grep on maint). Separately, any test case
    failing with a printable-string reason now logs it without quotes.
    Stack frames for undef and function_clause include call
    arguments (for a hook, possibly the whole Config), and these now
    travel in events as well.

  • Classification: potentially incompatible (Fix makefile in for xref mod app escript #8). The new term
    stays within the documented FailReason contract
    ({error,{RunTimeError,StackTrace}}), but consumers that relied on
    undocumented details see a different term or text.

  • Precedent: common_test has shipped changes like this on maint
    with the *** POTENTIAL INCOMPATIBILITY *** tag
    (lib/common_test/doc/notes.md on maint):

    • Common_Test 1.17.2 and 1.15.4.2 (both patch releases):
      post_init_per_testcase hook failures handled uniformly however
      the hook process failed. This is the closest analogue: a
      hook-failure behaviour change.
    • OTP-12279: tc_done Result changed to ok to match the docs.
  • WHAT: no need to move the PR to master. The release note
    should carry the tag. The earlier "maint vs master" question and
    the "keep it a string" alternative are dropped: a string-only
    design would also break exact-string matchers, since the text
    changes too.

  • HOW: OTP-20192 release note (Monitor OTP), for example:
    "When a CT hook callback fails, the failure reason now includes the
    exception class and reason, and is reported as
    {ReasonString, Stacktrace} instead of a plain string.
    *** POTENTIAL INCOMPATIBILITY ***"

"~ts",
[escape_chars(io_lib:format("=== Reason: " ++ FStr, [FormattedReason]))]),
?reason_prefix ++ "~ts",
[escape_chars(io_lib:format(FStr, [FormattedReason]))]),

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

AP-5 (Blocking, team rule #30): tab characters in 2 new or
modified lines:

  • test_server_ctrl.erl (unknown-location progress clause, about
    line 4162):
    \t [escape_chars(io_lib:format(FStr, [FormattedReason]))]),
  • ct_hooks_SUITE.erl (faulty_cth_long_reason/1, line 162):
    \t [crash_post_end_tc_cth],Config).

The surrounding code uses tabs, but the team rule requires spaces in
new and modified lines. CI will also reject them (verified): the
check-files job (.github/workflows/reusable-check-files.yaml on
maint, step "Detect whitespace errors") runs
git diff --check --merge-base with core.whitespace=tab-in-indent.
Running the same command locally against upstream/maint:

lib/common_test/src/test_server_ctrl.erl:4162: tab in indent.
lib/common_test/test/ct_hooks_SUITE.erl:162: tab in indent.
→ exit 2

This hasn't shown up yet only because CI hasn't run since the tabs were
added (#4.1).

@@ -1164,13 +1163,13 @@ catch_apply(M,F,A, Default, Fallback) ->
catch_apply(M,F,A) ->
try
erlang:apply(M,F,A)
catch _:Reason:Trace ->
catch Class:Reason:Trace ->

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

update commit msg pls

PF = fun(Term, I) ->
io_lib:format("~." ++ integer_to_list(I) ++ "tkp", [Term])
end,
PF = fun(Str, I) when is_list(Str), Str =:= Error ->

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

5.3 AP-6: Empty failure reason for error([])

Problem. With the PR, a test case that fails with the reason []
(for example erlang:error([]) or exit([])) gets an empty
=== Reason: line. Before the PR, the line showed [].

Why it happens. The new PF fun in
test_server_ctrl:do_format_exception/2 (PR head line 4424) prints
the error with ~ts (raw text, no quotes) whenever it is a printable
string. io_lib:printable_unicode_list([]) returns true, so [] is
treated as an empty string and printed as nothing.

Action (for Mikaka27). Add Str =/= [] to the guard of the first
PF clause, so [] falls through to the normal term printing:

PF = fun(Str, I) when is_list(Str), Str =/= [], Str =:= Error ->

That is the only change AP-6 asks for. Optionally, add a unit test
for do_format_exception/2 with [] (see AP-8).

Impact. Minor. Failing with [] is unusual, but when it happens
the log gives no hint about what went wrong.

Evidence: other inputs checked. I ran a copy of the PR's PF
logic with the fresh bin/escript. The PF fun formats the reason
of every failing test case, not only CTH failures, so I tried
several inputs:

erlang:error(E) Before (~tp) After Verdict
[] [] (empty) ❌ AP-6
[0,1,2] [0,1,2] [0,1,2] ✅ (Copilot issue, fixed)
"abc" "abc" abc quotes dropped; covered by the AP-4 release note
"line1\nline2" "line1\nline2" 2 lines, second indented 12 columns ✅ intended
#{b=>1,a=>2} sorted on maint-28+ (~tkp) ~tp (unsorted) on this base see AP-1
error "abc", stack frame m:f("abc") — called as m:f("abc") (arguments stay quoted) ✅

Note on ~tkp (AP-1, not part of AP-6). The PF fun uses ~tp,
which on maint-28 and later should be ~tkp (map keys sorted, from
f35c2a9d2b). Until now this was handled in the opu forward merges.
After the planned rebase onto maint-29 (AP-2), it has to be in the PR
itself: both PF clauses should use tkp. The k modifier exists
since OTP 27, so this is not a technical limitation.

Comment thread lib/common_test/test/ct_hooks_SUITE.erl Outdated
@@ -159,6 +157,10 @@ faulty_cth_undef(Config) when is_list(Config) ->
do_test(faulty_cth_undef, "ct_cth_empty_SUITE.erl",
[undef_cth],Config).

faulty_cth_long_reason(Config) when is_list(Config) ->
do_test(faulty_cth_long_reason, "ct_cth_empty_SUITE.erl",
[crash_post_end_tc_cth],Config).

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

what do you think about simple verification? can you resist 2nd time ;-)?

6. AP-8: Tests Don't Check the Log Output

Problem. The PR's feature is the === Reason: line in the test
case log, but no test reads that log. The tests only check event
payloads (tc_done, on_tc_fail), and those are built in
ct_hooks / ct_framework before test_server_ctrl formats
anything.

Evidence (#5.4). With all the PR's test_server_ctrl.erl changes
removed (shift_stacktrace/2, the new PF, the prefix handling), the
4 cases still pass, while the log regresses: quoted string, literal
\n, and the doubled === === Reason: prefix. So a later change can
break the feature, or bring back the doubled-prefix bug, without any
test failing.

Check Status
New/modified tests included? Yes
Event payload covered? Yes
=== Reason: log rendering covered? No
[] / [0,1,2] edge cases (#5.3) covered? No

Action (for Mikaka27). Extend faulty_cth_undef (or
faulty_cth_long_reason) with a check on the rendered test case log.
Optional: AP-6 coverage, see below.

Is it complex? No: about 20 lines, in the test suite only, verified to work.
Everything it needs already exists in ct_hooks_SUITE:

  • do_test/4 (line 484) already returns the start options, which
    contain logdir.
  • cth_log_formatter/1 (line 315) and verify_cth_log_output/3
    (line 535) already do the same thing: filelib:wildcard/1 for the
    test case log under logdir, file:read_file/1, then match lines.

Tested sketch (4-space indentation). I applied it locally to the PR
head, then reverted it:

  • with the PR: faulty_cth_undef passes
  • with the base test_server_ctrl.erl (as in Yecc better error message #5.4): it fails
    with {badmatch,false}

So it detects exactly the regression the current tests miss.

faulty_cth_undef(Config) when is_list(Config) ->
    StartOpts = do_test(faulty_cth_undef, "ct_cth_empty_SUITE.erl",
                        [undef_cth], Config),
    Logdir = proplists:get_value(logdir, StartOpts),
    %% ct_test_support runs the inner test twice, so expect >= 1 log
    TCLogs = filelib:wildcard(
               filename:join(Logdir,
                             "ct_run*/cth.tests*/run*/"
                             "ct_cth_empty_suite.init_per_suite.html")),
    [_|_] = TCLogs,
    lists:foreach(
      fun(TCLog) ->
              {ok, Bin} = file:read_file(TCLog),
              Log = binary_to_list(Bin),
              %% reason line with class and reason
              true = nomatch =/=
                  string:find(Log, "=== Reason: undef_cth:pre_init_per_suite/3 "
                                   "CTH call failed: error:undef"),
              %% stack frames follow the reason
              true = nomatch =/= string:find(Log, "in function  lists:flaten/1"),
              %% no doubled prefix
              nomatch = string:find(Log, "=== === Reason:")
      end, TCLogs).

The one surprise while testing it: ct_test_support runs every inner
test twice, so there are 2 matching logs. A [TCLog] = … match
fails with badmatch; loop over all logs, as cth_log_formatter/1
does.

Effort: about 30 minutes, including a test run (each ct_hooks_SUITE case takes ~5 s here). Change size: +22 / −2 lines in ct_hooks_SUITE.erl, nothing in src.

Possible pitfalls, low risk:

  • The HTML escapes <, > and & (escape_chars/1). The strings
    above contain none of them.
  • Don't assert the exact indentation of faulty_cth_long_reason;
    it depends on the module name length and line width (see the next
    paragraph).

Optional: AP-6 coverage. A direct unit test of
do_format_exception/2 for [], [0,1,2] and a multi-line string is
not cheap: the function isn't exported, and test_server_ctrl has
no -ifdef(TEST) export. It would need a new export or a test helper
in src. Instead, add a small test case to an existing data suite that
fails with erlang:error([]) and check its === Reason: line with
the same pattern as above. That's another ~15 lines.

Side note on the existing test. test_events(faulty_cth_long_reason)
hard-codes column widths (Ind(69), Ind(70) …). These come from the
~tp in ct_hooks (verified in #5.4), not from shift_stacktrace/2,
so the test is fragile against a rename of the hook module or a
change to the default line width, while still not testing
test_server_ctrl. Not a blocker; worth a comment in the test.

On the earlier dismissal. Mikaka27 dismissed Copilot's version of
this point as a "long standing problem, output of common test is not
tested". That's true in general, but in this PR the log output is
the feature (ERIERL-1336), and the infrastructure to test it is
already in the same suite, so the general argument is weaker here.

When a CT hook callback crashes, the test case log only shows a
generic "mod:fun/N CTH call failed" in the "=== Reason:" line. The
actual error and stacktrace are logged earlier in the "Suite Hook"
section but not propagated to the test summary.

ct_hooks now throws {ReasonString, Stacktrace}, where ReasonString
includes the exception class and reason, so the stacktrace is
rendered by test_server_ctrl as for any other failure.

test_server_ctrl prints a printable string reason as text instead
of a quoted term, and indents continuation lines of multi-line
reasons under the "=== Reason: " prefix. A doubled "=== Reason:"
prefix in the unknown-location failure path is also fixed.

Potential incompatibility: event handlers and hooks receiving the
CTH failure reason (tc_done, on_tc_fail, on_tc_skip) now see
{ReasonString, Stacktrace} instead of a plain string.
@Mikaka27
Mikaka27 force-pushed the kuba/common_test/hook_fail_test_log/OTP-20192 branch from 1c86749 to 405acc4 Compare October 23, 2026 12:37
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

team:PS Assigned to OTP team PS testing currently being tested, tag is used by OTP internal CI

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants